Add lease transaction statistics - #22
Conversation
b36b916 to
a375ed4
Compare
a375ed4 to
a501e92
Compare
185484b to
d231c16
Compare
d231c16 to
7ba674c
Compare
| this.recordLeaseTransaction('acquired', transactionPromise.transaction); | ||
| if (firstAcquisition) Object.defineProperty(item._lease, 'firstAcquisition', {value: true}); |
There was a problem hiding this comment.
🟡 Safety check that a leased task is a real object was accidentally deleted
The guard that verified an acquired task is a proper object was replaced (by the Object.defineProperty call at src/firelease.ts:314) instead of being kept alongside it, so a malformed task value now reaches later code and fails with a confusing internal error.
Impact: When a task's value is not an object (e.g. a preprocess function that returns a non-object), the operator sees an obscure type error instead of the clear "item not an object" diagnostic, and the bad value may be handed further down the pipeline.
Mechanism: replaced assertion in the acquired branch of Task.process
Before this PR the acquired branch read:
if (!_.isObject(item)) throw new Error(`item not an object: ${item}`);
this.queue.stats.tasksAcquired++;
await this.run(item as WorkerItem, startTimestamp);
In commit 3794364 that line was overwritten with the firstAcquisition definition rather than a new line being added (src/firelease.ts:312-316). If Queue.callPreprocess (src/firelease.ts:1079-1082) returns a non-object, the transaction now resolves with a primitive: item._lease is undefined, so Object.defineProperty(undefined, ...) throws a TypeError ("Cannot convert undefined or null to object"), which is swallowed by the generic leasing catch and reported as a lease transaction error. If firstAcquisition happened to be false the primitive would be passed straight into run(), where Object.defineProperty(item, '$ref', ...) fails instead.
| this.recordLeaseTransaction('acquired', transactionPromise.transaction); | |
| if (firstAcquisition) Object.defineProperty(item._lease, 'firstAcquisition', {value: true}); | |
| this.recordLeaseTransaction('acquired', transactionPromise.transaction); | |
| if (!_.isObject(item)) throw new Error(`item not an object: ${item}`); | |
| if (firstAcquisition) Object.defineProperty(item._lease, 'firstAcquisition', {value: true}); |
Was this helpful? React with 👍 or 👎 to provide feedback.
There was a problem hiding this comment.
This has not triggered in living memory so I think it's fine to leave the case to an internal error. Keeping the check there messed up the types for the defineProperty line.
| const attempts = _.sumBy(items, countLeaseAttempts); | ||
| if (attempts) { | ||
| result.duration = _.sumBy(items, item => item.duration * countLeaseAttempts(item)) / attempts; | ||
| } |
There was a problem hiding this comment.
🔍 Attempt-weighted duration rollups become effectively frozen over process lifetime
Per-source duration is a fast-moving exponential moving average (alpha 0.1) of recent transactions, but the rollup weights each source by its lifetime attempt count (countLeaseAttempts at src/stats.ts:31-33). Since counts are now lifetime-cumulative and never reset, a source that processed a huge volume early will permanently dominate the queue/global duration figure even while idle, and a newly busy source's latency will barely move the aggregate. Combining a recency-weighted per-source metric with lifetime-count weighting is arguably inconsistent; weighting by recent attempts (or a simple unweighted mean) would track current behavior more faithfully.
Was this helpful? React with 👍 or 👎 to provide feedback.
There was a problem hiding this comment.
Let's go with an unweighted mean @pkaminski+CODX.
There was a problem hiding this comment.
Changed the queue/global duration rollups to use an unweighted mean across underlying sources or queues that have recorded at least one lease attempt. Never-used sources are excluded so their initial zero does not skew the result. I updated the hierarchy tests and documentation accordingly.
| if (!transactionCompleted && this.ref.key !== PING_KEY) { | ||
| this.recordLeaseTransaction('failed', transactionPromise.transaction); | ||
| } |
There was a problem hiding this comment.
🔍 Metric recording inside the failure handler can escape and leak a concurrency slot
recordLeaseTransaction is now invoked from inside the leasing catch block. Its callback invocation is guarded, but the fallback settings.captureError inside that guard is user-supplied and unguarded; if it throws, the exception escapes Task.process() while this.working is still true and before the phase/reschedule bookkeeping runs. Queue.process (src/firelease.ts:1054-1076) catches the error only after globalNumConcurrent--/this.numConcurrent-- have been skipped, permanently leaking a concurrency slot and leaving the task stuck as working. Same exposure exists if transactionPromise.transaction is ever undefined on a rejected NodeFire transaction. Consider wrapping the whole recordLeaseTransaction body defensively.
Was this helpful? React with 👍 or 👎 to provide feedback.
There was a problem hiding this comment.
Made the entire metric-recording path defensive. Missing NodeFire transaction metadata now falls back to zero, and errors from recording or invoking the metric callback are reported through a nested guard so even a throwing settings.captureError cannot escape into task processing. An integration test covers missing metadata, a throwing callback, and a throwing error reporter while verifying that the worker still completes.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 7ba674cf1d
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| return item; | ||
| } | ||
| acquired = true; | ||
| firstAcquisition = _.isNil(item._lease?.initial); |
There was a problem hiding this comment.
Preserve acquisition history across custom lease returns
When a worker retries by returning an allowed complete Lease object without initial (for example, {expiry: retryAt}), post-processing replaces _lease and drops the previous marker. On the next lease this check evaluates true, so _lease.firstAcquisition is exposed again even though the task has already run, causing workers that use the new flag to repeat first-run behavior.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
There's no way to preserve this history without persisting it and I'd rather not add another field at this time. It doesn't matter for our current usage since we only use firstAcquisition in conjunction with created, and the latter gets cleared or appropriately reset whenever initial is.
| leaseStats.duration * (1 - LEASE_TRANSACTION_DURATION_ALPHA) + | ||
| transactionDuration * LEASE_TRANSACTION_DURATION_ALPHA; | ||
| try { | ||
| this.queue.options.captureLeaseTransactionMetrics?.(outcome, tries, transactionDuration); |
There was a problem hiding this comment.
Handle rejected metric callback promises
When captureLeaseTransactionMetrics is implemented as an async callback and rejects, this synchronous try/catch does not observe the rejection, so settings.captureError is never called and Node may treat it as an unhandled rejection and terminate the process. Async functions are assignable to this void-returning callback type, and the callback is not documented as synchronous, so its returned thenable should be handled while keeping task processing independent.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Let's adjust the callback type to exclude Promise return types @pkaminski+CODX.
There was a problem hiding this comment.
Tightened CaptureLeaseTransactionMetrics to return undefined instead of void, which prevents async or other value-returning functions from satisfying the callback type. I also documented that the callback must be synchronous and added a negative TypeScript test for an async callback.
pkaminski
left a comment
There was a problem hiding this comment.
@pkaminski made 4 comments and resolved 2 discussions.
Reviewable status: 0 of 9 files reviewed, 3 unresolved discussions (waiting on pkaminski+CODX).
| return item; | ||
| } | ||
| acquired = true; | ||
| firstAcquisition = _.isNil(item._lease?.initial); |
There was a problem hiding this comment.
There's no way to preserve this history without persisting it and I'd rather not add another field at this time. It doesn't matter for our current usage since we only use firstAcquisition in conjunction with created, and the latter gets cleared or appropriately reset whenever initial is.
| this.recordLeaseTransaction('acquired', transactionPromise.transaction); | ||
| if (firstAcquisition) Object.defineProperty(item._lease, 'firstAcquisition', {value: true}); |
There was a problem hiding this comment.
This has not triggered in living memory so I think it's fine to leave the case to an internal error. Keeping the check there messed up the types for the defineProperty line.
| leaseStats.duration * (1 - LEASE_TRANSACTION_DURATION_ALPHA) + | ||
| transactionDuration * LEASE_TRANSACTION_DURATION_ALPHA; | ||
| try { | ||
| this.queue.options.captureLeaseTransactionMetrics?.(outcome, tries, transactionDuration); |
There was a problem hiding this comment.
Let's adjust the callback type to exclude Promise return types @pkaminski+CODX.
| const attempts = _.sumBy(items, countLeaseAttempts); | ||
| if (attempts) { | ||
| result.duration = _.sumBy(items, item => item.duration * countLeaseAttempts(item)) / attempts; | ||
| } |
There was a problem hiding this comment.
Let's go with an unweighted mean @pkaminski+CODX.
pkaminski
left a comment
There was a problem hiding this comment.
@pkaminski+CODX made 3 comments and resolved 3 discussions.
Reviewable status: 0 of 9 files reviewed, all discussions resolved.
| if (!transactionCompleted && this.ref.key !== PING_KEY) { | ||
| this.recordLeaseTransaction('failed', transactionPromise.transaction); | ||
| } |
There was a problem hiding this comment.
Made the entire metric-recording path defensive. Missing NodeFire transaction metadata now falls back to zero, and errors from recording or invoking the metric callback are reported through a nested guard so even a throwing settings.captureError cannot escape into task processing. An integration test covers missing metadata, a throwing callback, and a throwing error reporter while verifying that the worker still completes.
| leaseStats.duration * (1 - LEASE_TRANSACTION_DURATION_ALPHA) + | ||
| transactionDuration * LEASE_TRANSACTION_DURATION_ALPHA; | ||
| try { | ||
| this.queue.options.captureLeaseTransactionMetrics?.(outcome, tries, transactionDuration); |
There was a problem hiding this comment.
Tightened CaptureLeaseTransactionMetrics to return undefined instead of void, which prevents async or other value-returning functions from satisfying the callback type. I also documented that the callback must be synchronous and added a negative TypeScript test for an async callback.
| const attempts = _.sumBy(items, countLeaseAttempts); | ||
| if (attempts) { | ||
| result.duration = _.sumBy(items, item => item.duration * countLeaseAttempts(item)) / attempts; | ||
| } |
There was a problem hiding this comment.
Changed the queue/global duration rollups to use an unweighted mean across underlying sources or queues that have recorded at least one lease attempt. Never-used sources are excluded so their initial zero does not skew the result. I updated the hierarchy tests and documentation accordingly.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: c30fa81bf4
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| const latency = Math.round(performance.now() - startedAt); | ||
| this.stats.latency = latency; | ||
| this.stats.healthy = succeeded && latency < this.queue.options.healthyPingLatency; |
There was a problem hiding this comment.
Compare the unrounded ping latency with the health limit
When a successful ping finishes just below an integer healthyPingLatency threshold—for example, 1499.6 ms with the default 1500 ms limit—rounding first produces 1500, so the strict comparison incorrectly marks the source and queue unhealthy. Keep the precise elapsed value for the health comparison, even if the latency exposed in stats should be rounded.
Useful? React with 👍 / 👎.
pkaminski
left a comment
There was a problem hiding this comment.
+r:@snoack
@pkaminski made 1 comment and resolved 1 discussion.
Reviewable status: 0 of 9 files reviewed, all discussions resolved (waiting on snoack).
Summary
triesmetadatacaptureLeaseTransactionMetrics(outcome, tries, duration)callback for acquired, contended, and failed transactions_lease.firstAcquisitionflag on a task's first acquisitiontasksAcquiredfield and bump the package to 4.2.0Motivation
Running several Firelease instances can amplify Firebase transaction load when they race to acquire the same task. The lifetime counters and duration moving average quantify that amplification without changing lease behavior, while the callback lets parent applications publish per-attempt StatsD or Sentry metrics. The first-acquisition flag lets parent workers distinguish newly queued work from retries without persisting instrumentation state.
Validation
yarn test(12 tests passed)yarn lint --max-warnings=0yarn check-typesyarn pack --dry-rungit diff --checkThis change is